查看原文
其他

记一次 .NET游戏站程序的 CPU 爆高分析

DotNet 2021-12-16

The following article is from 一线码农聊技术 Author 一线码农聊技术

一、讲故事

上个月有个老朋友找到我,说他的站点晚高峰 CPU 会突然爆高,发了两份 dump 文件过来,如下图:

又是经典的 CPU 爆高问题,到目前为止,对这种我还是有一些经验可循的。

  • 抓 2-3 个 dump

第一个:有利于算两份 dump 中的线程时间差,从而推算最耗时线程。

第二个:有时候你抓的dump刚好线程都处理完了,cpu 还未真实回落,所以分析这种dump意义不大,我是吃了不少亏。

  • 优先推测是否为 GC 捣鬼

现在的码农都精怪精怪的,基本不会傻傻的写出个死循环,绝大部分都是遇到某种 资源密集型计算密集型 场景下导致非托管的 GC 出了问题。

好了,有了这个先入为主的思路,接下来就可以用 windbg 去占卜了。

二、windbg 分析

1. GC 捣鬼分析

GC 捣鬼的本质是 GC 出现了回收压力,尤其是对 大对象堆 的分配和释放,大家应该知道 大对象堆 采用的是链式管理法,不到万不得已 GC 都不敢回收它,所以在它上面的分配和释放都是一种 CPU密集型 操作,不信你可以去 StackOverflow 上搜搜 LOH 和 HighCPU 的关联关系。

2. 使用 x 命令搜索

在 windbg 中有一个快捷命令 x ,可用于在非托管堆上检索指定关键词,检索之前先看看这个 dump 是什么 Framework 版本,决定用什么关键词。

0:050> lmv
start    end        module name
00b80000 00b88000   w3wp       (pdb symbols)          c:\mysymbols\w3wp.pdb\0CED8B2D5CB84AEB91307A0CE6BF528A1\w3wp.pdb
    Loaded symbol image file: w3wp.exe
    Image path: C:\Windows\SysWOW64\inetsrv\w3wp.exe
    Image name: w3wp.exe
71510000 71cc0000   clr        (pdb symbols)          c:\mysymbols\clr.pdb\9B2B2A02EC2D43899F87AC20F11B82DF2\clr.pdb
    Loaded symbol image file: clr.dll
    Image path: C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
    Image name: clr.dll
    Browse all global symbols  functions  data
    Timestamp:        Thu Sep  3 03:30:58 2020 (5F4FF2F2)
    CheckSum:         007AC92B
    ImageSize:        007B0000
    File version:     4.8.4261.0
    Product version:  4.0.30319.0

File version 上可以看出当前是基于 Net Framework 4.8 的,好了,用 x clr!SVR::gc_heap::trigger* 看看有没有触发 gc 的操作。

0:050> x clr!SVR::gc_heap::trigger*
71930401          clr!SVR::gc_heap::trigger_ephemeral_gc (protectedint __thiscall SVR::gc_heap::trigger_ephemeral_gc(enum gc_reason))
71665cf9          clr!SVR::gc_heap::trigger_gc_for_alloc (protectedvoid __thiscall SVR::gc_heap::trigger_gc_for_alloc(int,enum gc_reason,struct SVR::GCDebugSpinLock *,bool,enum SVR::msl_take_state))
71930a08          clr!SVR::gc_heap::trigger_full_compact_gc (protectedint __thiscall SVR::gc_heap::trigger_full_compact_gc(enum gc_reason,enum oom_reason *,bool))

从输出信息看,gc 果然在高速运转,开心哈,接下来看一下是哪一个线程触发了gc,可以用 !eestack 把所有线程的托管和非托管堆栈打出来。

从图中可以看到当前 50 号线程的 GetUserLoginGameMapIds() 方法进行的大对象分配 try_allocate_more_space 触发了 clr!SVR::gc_heap::trigger_gc_for_alloc GC回收操作,最后 GC 通过 clr!SVR::GCHeap::GarbageCollectGeneration 进行回收,既然在回收,必然有很多线程正在卡死。

接下来再看看有几个线程正在共同努力做多 GetUserLoginGameMapIds() 方法。

到这里基本就能确定是 gc 捣的鬼。接下来的兴趣点就是 GetUserLoginGameMapIds() 到底在干嘛?

3. 分析 GetUserLoginGameMapIds() 方法

接下来把方法的源码导出来,使用 !name2ee 找到其所属 module,然后通过 !savemodule 导出该 module 的源码。

0:050> !name2ee *!xxx.GetUserLoginGameMapIds
Module:      1c870580
Assembly:    xxx.dll
Token:       0600000b
MethodDesc:  1c877504
Name:        xxx.GetUserLoginGameMapIds(xxx.GetUserLoginGameMapIdsDomainInput)
JITTED Code Address: 1d5a2030
0:050> !savemodule  1c870580 E:\dumps\6.dll
3 sections in file
section 0 - VA=2000, VASize=112b8, FileAddr=200, FileSize=11400
section 1 - VA=14000, VASize=3c8, FileAddr=11600, FileSize=400
section 2 - VA=16000, VASize=c, FileAddr=11a00, FileSize=200

打开导出的 6.dll,为了最大保护隐私,我就把字段名隐藏一下, GetUserLoginGameMapIds() 大体逻辑如下。

public GetUserLoginGameMapIdsDomainOutput GetUserLoginGameMapIds(GetUserLoginGameMapIdsDomainInput input)
{
 List<int> xxxQueryable = this._xxxRepository.Getxxx();
 List<UserLoginGameEntity> list = this._userLoginGameRepository.Where((UserLoginGameEntity u) => u.xxx == input.xxx, null"").ToList<UserLoginGameEntity>();
 List<int> userLoginGameMapIds = (from u in list select u.xxx).ToList<int>();
 IEnumerable<GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput> source = (from mc in (from mc in this._mapCategoryRepository.AsQueryable().ToList<MapCategoryEntity>()
 where userLoginGameMapIds.Any((int mid)
 => mid == mc.xxx) && mapIdsQueryable.Any((int xxx) => xxx == mc.xxx)
 select mc).ToList<MapCategoryEntity>()
 join u in list on mc.xxx equals u.xxx
 select new GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput
 {
  xxx = mc.xxx,
  xxx = ((u != null) ? new DateTime?(u.xxx) : null).GetValueOrDefault(DateTime.Now)
 } into d
 group d by d.MapId).Select(delegate(IGrouping<int, GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput> g)
 {
  GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput getUserLoginGameMapIdsDataDomainOutput = new GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput();
  getUserLoginGameMapIdsDataDomainOutput.xxx = g.Key;
  getUserLoginGameMapIdsDataDomainOutput.xxx = g.Max((GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput v) => v.xxxx);
  return getUserLoginGameMapIdsDataDomainOutput;
 });
 return new GetUserLoginGameMapIdsDomainOutput
 {
  Data = source.ToList<GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput>()
 };
}

看的出来,这是一段EF读取DB的复杂写法,朋友说这段代码涉及到了多张表的关联操作,算是一个 资源密集型 的方法。

4. 到底持有什么大对象?

方法逻辑看完了,接下来看下 GetUserLoginGameMapIds() 方法到底分配了什么大对象触发了GC,可以探究下 50 线程的调用栈,使用 !clrstack -a 调出所有的 参数 + 局部 变量。

0:050> !clrstack -a
OS Thread Id: 0x11a0 (50)
Child SP       IP Call Site
2501d350 7743c0bc [HelperMethodFrame: 2501d350] 
2501d3dc 704fbab5 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].set_Capacity(Int32)
    PARAMETERS:
        this (<CLR reg>) = 0x08053f6c
        value = <no data>
    LOCALS:
        <no data>

2501d3ec 704fba62 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].EnsureCapacity(Int32)
    PARAMETERS:
        this = <no data>
        min = <no data>
    LOCALS:
        <no data>

2501d3f8 70516799 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].Add(System.__Canon)
    PARAMETERS:
        this (<CLR reg>) = 0x08053f6c
        item (<CLR reg>) = 0x2d7b07bc
    LOCALS:
        <no data>

从调用栈上看,由于 EF 的读取逻辑需要向 List 中添加一条记录刚好触发了List的扩容机制,就是因为这个扩容导致了GC大对象分配。

那怎么看呢? 很简单,先把 this (<CLR reg>) = 0x08053f6c 中地址拿出来do一下 !do 0x08053f6c 调出 List。

0:050> !do 0x08053f6c
Name:        System.Collections.Generic.List`1[[xxx.MapCategoryEntity, xxx.Entities]]
MethodTable: 1e81eed0
EEClass:     70219c7c
Size:        24(0x18) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
      MT    Field   Offset                 Type VT     Attr    Value Name
701546bc  40018a0        4     System.__Canon[]  0 instance 168792c0 _items
701142a8  40018a1        c         System.Int32  1 instance    32768 _size
701142a8  40018a2       10         System.Int32  1 instance    32768 _version
70112734  40018a3        8        System.Object  0 instance 00000000 _syncRoot
701546bc  40018a4        4     System.__Canon[]  0   static  <no information>

上面的 _size = 32768 看到了吗?刚好是 2的15次方,由于再次新增必须要扩容,List 在底层需分配一个 System.__Canon[65536] 的数组来存储老内容,这个数组肯定大于 85000byte 这个大对象的界定值啦。

如果有兴趣,你可以看下 List 的扩容机制。

// System.Collections.Generic.List<T>
private void EnsureCapacity(int min)
{
 if (_items.Length < min)
 {
  int num = (_items.Length == 0) ? 4 : (_items.Length * 2);
  if ((uint)num > 2146435071u)
  {
   num = 2146435071;
  }
  if (num < min)
  {
   num = min;
  }
  Capacity = num;
 }
}

public int Capacity
{

 get
 {
  return _items.Length;
 }
 set
 {
  if (value < _size)
  {
   ThrowHelper.ThrowArgumentOutOfRangeException(ExceptionArgument.value, ExceptionResource.ArgumentOutOfRange_SmallCapacity);
  }
  if (value == _items.Length)
  {
   return;
  }
  if (value > 0)
  {
   T[] array = new T[value];   //这里申请了一个 65536 大小的数组
   if (_size > 0)
   {
    Array.Copy(_items, 0, array, 0, _size);
   }
   _items = array;
  }
  else
  {
   _items = _emptyArray;
  }
 }
}

三、总结

知道了前因后果之后,大概提三点优化建议。

  • 优化 GetUserLoginGameMapIds() 方法中的逻辑,这是最好的办法。
  • 从 dump 上看也就 4核4G 的小机器,提升下机器配置,或许有点用。
0:017> !cpuid
CP  F/M/S  Manufacturer     MHz
 0  6,63,2  GenuineIntel    2295
 1  6,63,2  GenuineIntel    2295
 2  6,63,2  GenuineIntel    2295
 3  6,63,2  GenuineIntel    2295

 0:017> !address -summary
--- Protect Summary (for commit) - RgnCount ----------- Total Size -------- %ofBusy %ofTotal
PAGE_READWRITE                          878          1eccd000 ( 492.801 MB)  29.61%   12.03%
  • 没有特殊原因的话,用 64bit 来跑程序,打破 32bit 的 4G 空间限制,这样也可以让gc拥有更大的堆分配空间。

参考网址:https://docs.microsoft.com/zh-cn/dotnet/standard/garbage-collection/fundamentals

- EOF -

推荐阅读  点击标题可跳转

微软正式宣布 Visual Studio 2022

.NET 模板填充导出Excel工具 MiniExcel Template

又一起.NET程序挂死, 用Windbg抽丝剥茧式的真实案例分析


看完本文有收获?请转发分享给更多人

推荐关注「DotNet」,提升.Net技能 

点赞和在看就是最大的支持❤️

: . Video Mini Program Like ,轻点两下取消赞 Wow ,轻点两下取消在看

您可能也对以下帖子感兴趣

文章有问题?点此查看未经处理的缓存